Errores de representación
Primer dato modifica su time (23-3-2012) El primer dato insertdo usando la funcón db_pushNodeMetric siempre se modifica de la siguiente forma: Si el time del primer dato es: 1332506649275348 en la gráfica se representa como 1332506649000275. De forma que si solo se consideran los nanosegundos, el dato insertado era 275348 y el dato mostrado en la gráfica consiste en desplazar los milisegundos a nanosegundos y poner 000 en la parte de los milisegunos. Se quedará así 000275. Esto es lo que produce que el primer dato siempre se encuentre mucho antes en la gráfica que todos los demás. Además se entiende que en cada ejecución el valor del retardo se modifica de forma aleatoria. No se entiende que esta modificación solo ocurra con el primer dato, todos los demás se insertan en su lugar correcto, sin ningun retraso ni modificación del valor de su time. Investigando código de la función db_pushNodeMetric para averigura si al primer dato se le da una gestión especial. 1º Suposición: Puede que sea por la transformacion de los datos de uint64_t a long long int, pero esto ocurre con todos los times que usamos y en la representación solo falla el primero. Intentando crear datos uint64_t en el código de testapp.c No considera todos los datos (26-3-2012) Puede ser por dos motivos: -El push no inserta todos los datos correctamente en el fichero Energy.stat -Sunshot no lee correctamente todos los datos del fichero Energy.stat El primer paso es comprobar si todos los datos se escriben correctamente en el fichero Energy.stat, para ello voy a ejecutar varios ejemplos en los que se inserten diferentes cantidades de datos. No se puede contar cuantos datos tiene el fichero stat ya que están escritos en formato float y no se pueden leer directamente. La relación de datos insertados y tamaño del fichero es: 1 dato -> 291 bytes 2 datos -> 307 bytes Esto nos indica que el tamaño del fichero responde a la función: 275 + 16 x num_datos Ahora ejecutamos el ejemplo con todos los datos (282) y comprobamos cual es el tamaño en bytes del fichero stat que, se supone, los almacena todos: 282 datos -> 4787 bytes (en teoria) -> 2115 bytes (tamaño resultado) -> 115 datos almacenados en el fichero Energy.stat Ahora sabemos donde está el error. Comprobar código de la funvión db_pushNodeMetric() para averigura si tiene logs y como se pueden ver estos. Modificación de datos para averiguar errores (26-3-2012) Podemos encontrar el código de la función db_pushNodeMetric en ./hdtrace/DBConnector/src/DBConnector.c Se llama a la función QueryPuffer_addQuery(queryPuffer, metric,node,timestamp,value); El código de esta función se encuentra en el fichero ./hdtrace/DBConnector/src/QueryPuffer.c En el directorio /home/timo/hdtrace/DBConnector/build/default/src se encuentran dos ficheros .o que se corresponden con el código modificado: QueryPuffer_1.o QueryPuffer_2.o No se sabe la diferencia entre ellos. Mail a Enrique (28-3-2012) Hay algunos errores que creo que se producen en el código del HDTrace, para saber cuando y como ocurren quería añadir algunos prints en el código del HDTrace, después de esto evidentemente he de compilar el nuevo .c pero este produce muchos errores, debido a dependencias y librerías que no le paso en la linea de compilación. Al no existir ningún make no se como averiguar como debo compilar. Compilación e Instalación Para que las modificaciones en el código del HDTrace sean efectivas debemos compilar e instalar. Con el ejecutable waf podemos hacerlo todo: ./waf build ./waf install Todos los datos insertados correctamente (16-4-2012) Parece que todos los datos se inserten correctamente en la estrura de datos que los almacena para después escribirlos en el documento .stat Se ha insertado un printf antes de cada inserción y se han mostrado todos durante la ejecución: (QueryPuffer_addQuery) INSERT INTO watts1_power VALUES ( '1334572921730898', '55.547714' ) Comprobar lectura de datos Encontrar la linea en la que se leen los datos del consumo insertados anteriormente usando el addQuery, para comprobar que se leen todos y además correctamente. timo@watts1:~/hdtrace$ find . -name "*c" -exec grep SELECT {} \; snprintf(query, countChars, "SELECT * FROM %s_%s WHERE timestamp BETWEEN %lu AND %lu ;",node, metric, from_timestamp, to_timestamp); snprintf(query, countChars,"SELECT * FROM %s_%s WHERE timestamp BETWEEN %lu AND %lu ;",node, metric, from_timestamp, to_timestamp); timo@watts1:~/hdtrace$ find . -name "*c" -exec grep -l SELECT {} \; ./DBConnector/src/SQLiteConnector.c ./DBConnector/src/PostgresConnector.c Fallo del select Documento: /home/timo/hdtrace/DBConnector/src/PostgresConnector.c En la ejecución de la función int db_getNodeMetric(const char * metric, const char * node, const uint64_t from_timestamp, const uint64_t to_timestamp, row_struct ** rows) Existe un select que no obtiene todos los datos que deberían ser tratados, por lo tanto no se representan todos en la gráfica. La instrucción que obtiene estos datos es la siguiente: snprintf(query, countChars,"SELECT * FROM %s_%s WHERE timestamp BETWEEN %lu AND %lu ;",node, metric, from_timestamp, to_timestamp); Investigación PostGres Manual oficial: http://www.postgresql.org/docs/8.0/static/index.html Wiki de PostgreSQL: http://wiki.postgresql.org/wiki/Main_Page Acceso : http://www.postgresql.org/docs/7.4/static/app-psql.html Funciones usadas en el programa: http://www.postgresql.org/docs/8.2/static/libpq-exec.html Usando la linea: int db_initConnectionWithArgs(int bufferSize, const char *new_conninfo) { conninfo = strdup(new_conninfo); printf("Conexion -> %s\n", new_conninfo);fflush(stdout); return initConnection(bufferSize); } Se han obtemido los siguientes datos: Conexion -> dbname = metrics user = power password = power Acceso timo@watts1:~$ psql metrics -U power Ayuda de psql -> comando /? Listar tablas -> comando /d Datos obtenidos En la ejecución: *Número de datos: 283 *Primer dato: 1334915415295730 *Último dato: 1334915425260482 *Último dato representado: 1334915419288698 que se corresponde con el dato número 113 En la base de datos: *Existencia del primer dato, 1334915415295730: correcto *Existencia del último dato, 1334915425260482: correcto *Datos seleccionados con el select: 283 metrics=> select max(timestamp) from watts1_power; max ------------------ 1334915425260482 (1 fila) metrics=> select value from watts1_power where timestamp = 1334915415295730; value ----------- 49.453873 (1 fila) metrics=> SELECT count(*) FROM watts1_power WHERE timestamp BETWEEN 1334915415284091 AND 1334915425303079 ; count ------- 283 (1 fila) Por lo que se ha podido ver los datos se encuentran correctamente en la base de datos, además el select es totalmente correcto y obtiene todos los datos que necesita para representar toda la ejecución. De esta forma desde ahora se tendrá que investigar el código para comprobar donde falla. Aunque todo se reduce a la instucción select que no guarda todos los datos que le ofrece la base de datos. Motivo del error: g_async_queue_push Todos los comandos insert para alamcenar datos se invocan usando la función g_async_queue_push, esta función maneja el orden de las instrucciones usando una cola que almacena los inserts y los ejecuta de forma ordenada. http://www.gtk.org/api/2.6/glib/glib-Asynchronous-Queues.html Posteriormente la llamada al select que obtiene todos los datos de consumo eléctrico se hace directamente sin pasar por la cola. Al ejecutar el select todavía no se han ejecutado todos los inserts. Se debe utilizar una variable de sincronización para que no se ejecute el select antes de que se hayan insertado todos los datos. No se puede asignar con ninguna estructura connection o relacionada con la base de datos ya que esta se inicia y se cierra en cada uno de los procesos de forma independiente. Solución: coordinación entre las dos hebras que ejecutan los inserts y los selects - - - - - - - - - - - - - - - - - - - -SELECT --------------------------------------- El select se ejecuta en la función db_getNodeMetric en el fichero /home/timo/hdtrace/DBConnector/src/PostgresConnector.c Se llama desde: La función rut_finalizeTrace en el fichero ./piosimhd/ResourcesUtilizationTracingLibrary/src/RUT.c Se llama desde el programa principal (test, cholesky). - - - - - - - - - - - - - - - - - - - -INSERT --------------------------------------- Los inserts se ejecutan en la función QueryPuffer_addQuery en el fichero home/timo/hdtrace/DBConnector/src/QueryPuffer.c Se llama desde: La función db_pushNodeMetric en el fichero ./hdtrace/DBConnector/src/DBConnector.c Se llama directamente desde el programa en ejecución (test, cholesky). Con cada dato obtenido se ejecuta una vez esta función. Pero en ningun momento se observa la creación de ningun thread (hilo). Posibles funciones que crean threads: - hdT_createTopoNode ./piosimhd/HDTraceWritingCLibrary/src/hdTopo.c -> Añade un nodo a la topologia. Como sincronizar nodos?? Buscando declaración del hdTopoNode: find . -name "*.h" -exec grep hdTopoNode {} \; | grep struct Al tener una complejidad muy grande se ha decidido coordinar los dos procesos usando la base de datos de forma que se inserta un dato al final de todos los datos y hasta que no este este dato no se ejecuta el select. Para sincronizar se inserta una fila (con value =-1) después de insertar todos los datos obtenidos con el pmlib, de esta forma el proceso encargado de hacer el SELECT de los datos insertados no ejecuta dicha consulta hasta que no encuentra en la base de datos un dato con timestamp de esta ejecución y con value -1. Se queda encerrado dentro de un bucle while haciendo consultadas hasta que obtiene la fila mencionada. Se realizan gran cantidad de consultas para comprobar la existencia del dato -1 pero no se puede usar ningun sleep para minimizarlo porque el método de fucninamiento de la topologia con sus nodos abandonan la ejecución de una función si esta entra en un sleep. Posteriormente en el bucle que inserta todos los datos en los ficheros para que el sunshot los lea solo debe ejecutarse hasta la penúltima fila seleccionada (ya que la última es el -1), en el fichero /home/timo/hdtrace/DBConnector/src/PostgresConnector.c en la función db_getNodeMetric se hace así: Simplemente lee los datos de la consulta y los copia a memoria. for (i = 0; i < countRows - 1; ++i) { sscanf(PQgetvalue(res, i, 0), "%lu", &row.timestamp); sscanf(PQgetvalue(res, i, 1), "%lf", &row.value); //printf("Time = %lu, value = %lf.\n", row.timestamp, row.value); memcpy(*rows + i, &row, sizeof(row)); } return countRows-1; Para que la siguiente función no tenga problemas: Además en el fichero ./piosimhd/ResourcesUtilizationTracingLibrary/src/RUT.c la función inicia la gestión de los datos para que se inserten en los ficheros que después leerá sunshot. int crows = db_getNodeMetric("power", myTrace->node_pt->node, myTrace->node_pt->from_timestamp, myTrace->node_pt->to_timestamp, &rows); for (int i = 0; i < crows; i++) { hdS_writeDoubleValueAtTimestamp(myTrace->node_pt->group, rowsi.value, rowsi.timestamp * MULTIPLIER); } Busqueda del error del primer dato En el documeno ./piosimhd/ResourcesUtilizationTracingLibrary/src/RUT.c En la función int rut_finalizeTrace(UtilTrace *trace) Se obtienen los datos de la base de datos (correctos en la función que los produce) los gestiona y se los pasa a otra función. He insertado un printf para observar si los datos son correctos y si que los son. for (int i = 0; i < crows; i++) { hdS_writeDoubleValueAtTimestamp(myTrace->node_pt->group, rowsi.value, rowsi.timestamp * MULTIPLIER); } Esta función se encuentra en el fichero ./piosimhd/HDTraceWritingCLibrary/src/hdStats.c Manteniendo el valor del timestamp se ejecuta la función: ret = appendValueAtTimestampToGroupBuffer(group, &value, DOUBLE, timestamp); La función se encuentra en el mismo fichero y llama a la función: writeGivenTimestampToGroupBuffer(group, timestamp); El primer dato se inserta dos veces: desde hdS_commitGroupAtTimestamp writeGivenTimestampToGroupBuffer Group 'Energy': timestamp=1335435673.000877582 desde appendValueAtTimestampToGroupBuffer Primero??? o todos?? writeGivenTimestampToGroupBuffer Group 'Energy': timestamp=1335435673.877582000 hdS_writeDoubleValueAtTimestamp Group 'Energy': type=DOUBLE value=59.063393 timestamp=1335435673877582000 Una sin valor, debe ser para iniciar la gráfica. El valor del timestamp ya se ha modificado, aquí debe estar el fallo. El primer dato se inserta dos veces, uno como inicio el otro como primer dato. Después de insertar printf en todos los lugares críticos se observa lo siguiente: Inicio: Llamo hdS_commitGroupAtTimestamp con timestamp: 1335773823823451 hdS_commitGroupAtTimestamp valor del TS = 1335773823823451 desde hdS_commitGroupAtTimestamp hdS_commitGroupAtTimestamp valor del TS = 1335773823823451 writeGivenTimestampToGroupBuffer Antes de convertir timestamp=1335773823823451 writeGivenTimestampToGroupBuffer Group 'Energy': timestamp=1335773823.000823451 Primer dato: desde appendValueAtTimestampToGroupBuffer Primero??? o todos?? writeGivenTimestampToGroupBuffer Antes de convertir timestamp=1335773823823451000 writeGivenTimestampToGroupBuffer Group 'Energy': timestamp=1335773823.823451000 hdS_writeDoubleValueAtTimestamp Group 'Energy': type=DOUBLE value=51.797661 timestamp=1335773823823451000 Se observa que en la inserción del inicio el dato del tiempo es el mismo que en el primer dato pero en otro magnitud. La diferencia reside en una de diferencia de un factor 1000, intentare multiplicar el valor del TS en la función hdS_commitGroupAtTimestamp. Añado la siguiente linea: int hdS_commitGroupAtTimestamp ( hdStatsGroup *group, /* Statistics Group */ uint64_t timestamp ) { timestamp = timestamp - 5000; timestamp = timestamp * 1000; printf("hdS_commitGroupAtTimestamp valor del TS = %ld\n", timestamp); Todo correcto Todo funciona, los errores se han solucionado modificando el primer valor y sincronizando los procesos usando la base de datos. Imagen funcionando: thumb|left|400px|HDTrace funcionando